Fix rake test loader swallowing useful error information #367

deivid-rodriguez · 2020-11-11T16:29:44Z

I got a bug report in bundler where the end user error being printed was like this:

$ bundle exec rake test

File does not exist: pry

rake aborted!
Command failed with status (1)
/home/deivid/Code/ruby/rake/exe/rake:27:in `<top (required)>'
/home/deivid/.rbenv/versions/2.7.2/bin/bundle:23:in `load'
/home/deivid/.rbenv/versions/2.7.2/bin/bundle:23:in `<main>'
Tasks: TOP => test
(See full trace by running task with --trace)

This error is very unhelpful about what's going on.

After debugging, I found that rake was swallowing useful information about the error, and also incorrectly stating that a file named "pry" was missing.

This changeset should fix the problem and now rake gives more useful information:

$ bundle exec rake test
Traceback (most recent call last):
	11: from /home/deivid/.rbenv/versions/2.7.2/lib/ruby/site_ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
	10: from /home/deivid/.rbenv/versions/2.7.2/lib/ruby/site_ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
	 9: from /home/deivid/Code/ruby/rake/lib/rake/rake_test_loader.rb:5:in `<top (required)>'
	 8: from /home/deivid/Code/ruby/rake/lib/rake/rake_test_loader.rb:5:in `select'
	 7: from /home/deivid/Code/ruby/rake/lib/rake/rake_test_loader.rb:16:in `block in <top (required)>'
	 6: from /home/deivid/.rbenv/versions/2.7.2/lib/ruby/site_ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
	 5: from /home/deivid/.rbenv/versions/2.7.2/lib/ruby/site_ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
	 4: from /tmp/repro/test/vendor/bundle/ruby/2.7.0/gems/activerecord-import-1.0.7/test/jdbcmysql/import_test.rb:1:in `<top (required)>'
	 3: from /home/deivid/.rbenv/versions/2.7.2/lib/ruby/site_ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
	 2: from /home/deivid/.rbenv/versions/2.7.2/lib/ruby/site_ruby/2.7.0/rubygems/core_ext/kernel_require.rb:83:in `require'
	 1: from /tmp/repro/test/vendor/bundle/ruby/2.7.0/gems/activerecord-import-1.0.7/test/test_helper.rb:13:in `<top (required)>'
/tmp/repro/test/vendor/bundle/ruby/2.7.0/gems/activerecord-import-1.0.7/test/test_helper.rb:13:in `require': cannot load such file -- pry (LoadError)
rake aborted!
Command failed with status (1)
/home/deivid/Code/ruby/rake/exe/rake:27:in `<top (required)>'
/home/deivid/.rbenv/versions/2.7.2/bin/bundle:23:in `load'
/home/deivid/.rbenv/versions/2.7.2/bin/bundle:23:in `<main>'
Tasks: TOP => test
(See full trace by running task with --trace)

eregon · 2020-11-11T17:22:33Z

Big 👍 from me :)

deivid-rodriguez · 2021-02-03T13:31:44Z

Hello rake maintainers, what do you think about this?

deivid-rodriguez · 2021-04-23T08:54:17Z

I was thinking that maybe this changeset appears to have too many changes. Unfortunately it looks more complicated than it is due to trying to keep consistent indentation. Here's the diff without whitespace, which should make reviewing this easier: https://github.com/ruby/rake/pull/367/files?w=1.

The idea is that instead of wrapping any LoadError's inside the loaded code and replacing them with a generic "File does not exist" error, we only raise that error if a file directly required does not exist, and otherwise let the original LoadError happen, which should have more accurate and useful information.

eregon · 2021-04-23T09:26:13Z

FYI I asked who are the maintainers of rake. Maybe @hsbt could review (looking at recent merges)?
Or if someone can add me with write access to this repo, I'd be happy to review this PR and possibly contribute more to rake.

deivid-rodriguez · 2021-04-23T09:38:08Z

I'm not in a hurry at all to get this PR reviewed, I imagine how busy maintainers must be. I just thought a comment trying to aid a future review could be helpful :)

deivid-rodriguez · 2021-06-12T13:07:06Z

I run into this again.

I tried to run actionmailbox test suite and got this:

/home/deivid/.rbenv/versions/3.0.1/bin/ruby -w -I"lib:test" /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb "test/controllers/ingresses/mailgun/inbound_emails_controller_test.rb" "test/controllers/ingresses/mandrill/inbound_emails_controller_test.rb" "test/controllers/ingresses/postmark/inbound_emails_controller_test.rb" "test/controllers/ingresses/relay/inbound_emails_controller_test.rb" "test/controllers/ingresses/sendgrid/inbound_emails_controller_test.rb" "test/controllers/rails/action_mailbox/inbound_emails_controller_test.rb" "test/generators/mailbox_generator_test.rb" "test/jobs/incineration_job_test.rb" "test/unit/inbound_email/incineration_test.rb" "test/unit/inbound_email/message_id_test.rb" "test/unit/inbound_email_test.rb" "test/unit/mail_ext/address_equality_test.rb" "test/unit/mail_ext/address_wrapping_test.rb" "test/unit/mail_ext/addresses_test.rb" "test/unit/mailbox/bouncing_test.rb" "test/unit/mailbox/callbacks_test.rb" "test/unit/mailbox/routing_test.rb" "test/unit/mailbox/state_test.rb" "test/unit/relayer_test.rb" "test/unit/router_test.rb" "test/unit/test_helper_test.rb" 
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32454: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32615: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32651: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32740: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32756: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32822: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32863: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32888: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:31984: warning: assigned but unused variable - testEof

File does not exist: capybara/window

rake aborted!
Command failed with status (1): [ruby -w -I"lib:test" /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb "test/controllers/ingresses/mailgun/inbound_emails_controller_test.rb" "test/controllers/ingresses/mandrill/inbound_emails_controller_test.rb" "test/controllers/ingresses/postmark/inbound_emails_controller_test.rb" "test/controllers/ingresses/relay/inbound_emails_controller_test.rb" "test/controllers/ingresses/sendgrid/inbound_emails_controller_test.rb" "test/controllers/rails/action_mailbox/inbound_emails_controller_test.rb" "test/generators/mailbox_generator_test.rb" "test/jobs/incineration_job_test.rb" "test/unit/inbound_email/incineration_test.rb" "test/unit/inbound_email/message_id_test.rb" "test/unit/inbound_email_test.rb" "test/unit/mail_ext/address_equality_test.rb" "test/unit/mail_ext/address_wrapping_test.rb" "test/unit/mail_ext/addresses_test.rb" "test/unit/mailbox/bouncing_test.rb" "test/unit/mailbox/callbacks_test.rb" "test/unit/mailbox/routing_test.rb" "test/unit/mailbox/state_test.rb" "test/unit/relayer_test.rb" "test/unit/router_test.rb" "test/unit/test_helper_test.rb" ]

Tasks: TOP => default => test

It's imposible to figure out what's going on 😞.

With this PR I get this:

/home/deivid/.rbenv/versions/3.0.1/bin/ruby -w -I"lib:test" /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb "test/controllers/ingresses/mailgun/inbound_emails_controller_test.rb" "test/controllers/ingresses/mandrill/inbound_emails_controller_test.rb" "test/controllers/ingresses/postmark/inbound_emails_controller_test.rb" "test/controllers/ingresses/relay/inbound_emails_controller_test.rb" "test/controllers/ingresses/sendgrid/inbound_emails_controller_test.rb" "test/controllers/rails/action_mailbox/inbound_emails_controller_test.rb" "test/generators/mailbox_generator_test.rb" "test/jobs/incineration_job_test.rb" "test/unit/inbound_email/incineration_test.rb" "test/unit/inbound_email/message_id_test.rb" "test/unit/inbound_email_test.rb" "test/unit/mail_ext/address_equality_test.rb" "test/unit/mail_ext/address_wrapping_test.rb" "test/unit/mail_ext/addresses_test.rb" "test/unit/mailbox/bouncing_test.rb" "test/unit/mailbox/callbacks_test.rb" "test/unit/mailbox/routing_test.rb" "test/unit/mailbox/state_test.rb" "test/unit/relayer_test.rb" "test/unit/router_test.rb" "test/unit/test_helper_test.rb" 
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32454: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32615: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32651: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32740: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32756: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32822: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32863: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:32888: warning: statement not reached
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/mail-2.7.1/lib/mail/parsers/address_lists_parser.rb:31984: warning: assigned but unused variable - testEof
/home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/zeitwerk-2.4.2/lib/zeitwerk/kernel.rb:34:in `require': cannot load such file -- capybara/window (LoadError)
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/zeitwerk-2.4.2/lib/zeitwerk/kernel.rb:34:in `require'
	from /home/deivid/Code/rails/activesupport/lib/active_support/dependencies.rb:320:in `block in require'
	from /home/deivid/Code/rails/activesupport/lib/active_support/dependencies.rb:290:in `load_dependency'
	from /home/deivid/Code/rails/activesupport/lib/active_support/dependencies.rb:320:in `require'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/capybara-3.35.3/lib/capybara.rb:455:in `<module:Capybara>'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/capybara-3.35.3/lib/capybara.rb:10:in `<top (required)>'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/zeitwerk-2.4.2/lib/zeitwerk/kernel.rb:34:in `require'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/zeitwerk-2.4.2/lib/zeitwerk/kernel.rb:34:in `require'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/site_ruby/3.0.0/bundler/runtime.rb:66:in `block (2 levels) in require'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/site_ruby/3.0.0/bundler/runtime.rb:61:in `each'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/site_ruby/3.0.0/bundler/runtime.rb:61:in `block in require'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/site_ruby/3.0.0/bundler/runtime.rb:50:in `each'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/site_ruby/3.0.0/bundler/runtime.rb:50:in `require'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/site_ruby/3.0.0/bundler.rb:174:in `require'
	from /home/deivid/Code/rails/actionmailbox/test/dummy/config/application.rb:5:in `<top (required)>'
	from /home/deivid/Code/rails/actionmailbox/test/dummy/config/environment.rb:2:in `require_relative'
	from /home/deivid/Code/rails/actionmailbox/test/dummy/config/environment.rb:2:in `<top (required)>'
	from /home/deivid/Code/rails/actionmailbox/test/test_helper.rb:6:in `require_relative'
	from /home/deivid/Code/rails/actionmailbox/test/test_helper.rb:6:in `<top (required)>'
	from /home/deivid/Code/rails/actionmailbox/test/controllers/ingresses/mailgun/inbound_emails_controller_test.rb:3:in `require'
	from /home/deivid/Code/rails/actionmailbox/test/controllers/ingresses/mailgun/inbound_emails_controller_test.rb:3:in `<top (required)>'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb:20:in `require'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb:20:in `block in <main>'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb:5:in `select'
	from /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb:5:in `<main>'
rake aborted!
Command failed with status (1): [ruby -w -I"lib:test" /home/deivid/.rbenv/versions/3.0.1/lib/ruby/gems/3.0.0/gems/rake-13.0.3/lib/rake/rake_test_loader.rb "test/controllers/ingresses/mailgun/inbound_emails_controller_test.rb" "test/controllers/ingresses/mandrill/inbound_emails_controller_test.rb" "test/controllers/ingresses/postmark/inbound_emails_controller_test.rb" "test/controllers/ingresses/relay/inbound_emails_controller_test.rb" "test/controllers/ingresses/sendgrid/inbound_emails_controller_test.rb" "test/controllers/rails/action_mailbox/inbound_emails_controller_test.rb" "test/generators/mailbox_generator_test.rb" "test/jobs/incineration_job_test.rb" "test/unit/inbound_email/incineration_test.rb" "test/unit/inbound_email/message_id_test.rb" "test/unit/inbound_email_test.rb" "test/unit/mail_ext/address_equality_test.rb" "test/unit/mail_ext/address_wrapping_test.rb" "test/unit/mail_ext/addresses_test.rb" "test/unit/mailbox/bouncing_test.rb" "test/unit/mailbox/callbacks_test.rb" "test/unit/mailbox/routing_test.rb" "test/unit/mailbox/state_test.rb" "test/unit/relayer_test.rb" "test/unit/router_test.rb" "test/unit/test_helper_test.rb" ]

Tasks: TOP => test
(See full trace by running task with --trace)

I don't yet know what's going on, but it gives me better information to start digging.

@hsbt Let me know if there's something I can do to get this reviewed 💪.

deivid-rodriguez force-pushed the remove_unhelpful_rescue branch from eef4f7e to bef15b8 Compare November 11, 2020 16:39

deivid-rodriguez mentioned this pull request Nov 11, 2020

File does not exist error when path is set and Gemfile inside test directory rubygems/rubygems#4055

Closed

deivid-rodriguez force-pushed the remove_unhelpful_rescue branch from bef15b8 to c955a5a Compare February 4, 2021 16:39

Fix rake test loader swallowing useful error information

17e69a5

deivid-rodriguez force-pushed the remove_unhelpful_rescue branch from c955a5a to 17e69a5 Compare June 12, 2021 13:07

hsbt merged commit 674cd79 into ruby:master Jul 6, 2021

deivid-rodriguez deleted the remove_unhelpful_rescue branch July 6, 2021 08:24

eregon mentioned this pull request Jul 29, 2021

Basic Bundler operations don't seem to work on Windows ruby/setup-ruby#209

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix rake test loader swallowing useful error information #367

Fix rake test loader swallowing useful error information #367

deivid-rodriguez commented Nov 11, 2020

eregon commented Nov 11, 2020

deivid-rodriguez commented Feb 3, 2021

deivid-rodriguez commented Apr 23, 2021

eregon commented Apr 23, 2021

deivid-rodriguez commented Apr 23, 2021

deivid-rodriguez commented Jun 12, 2021

Fix rake test loader swallowing useful error information #367

Fix rake test loader swallowing useful error information #367

Conversation

deivid-rodriguez commented Nov 11, 2020

eregon commented Nov 11, 2020

deivid-rodriguez commented Feb 3, 2021

deivid-rodriguez commented Apr 23, 2021

eregon commented Apr 23, 2021

deivid-rodriguez commented Apr 23, 2021

deivid-rodriguez commented Jun 12, 2021